Android ANR

您所在的位置：网站首页 › android inputdispatcher › Android ANR

Android ANR

#Android ANR| 来源: 网络整理| 查看: 265

作者：持笔写青春前言

网上关于ANR的技术文章很多，其中不乏优秀的精品，可为何当我们遇到ANR问题时，还是经常束手无策呢？

猜测一方面是不熟悉原理机制，还有一方面对CPU/RAM/IO/GC/Thermal、GC机制、内存分配、LMK机制、同步锁原理等基础掌握的不够。

本文侧重介绍常见的ANR类型以及一般分析策略，旨在希望通过本文能够处理绝大部分的ANR案例。

本文涉及代码基于Android S

画了一张图，列举了ANR的影响因素

ANR原理

我们平时遇到的ANR问题大部分是input ANR类型，本文以input ANR为例进行梳理，这块机制并不复杂，受限于篇幅，本文只介绍埋下计时和check超时的代码部分。

正常输入事件的分发流程如下

InputDispatcher::dispatchOnce() ->InputDispatcher::dispatchOnceInnerLocked ->InputDispatcher::dispatchKeyLocked ->InputDispatcher::findFocusedWindowTargetsLocked ......

findFocusedWindowTargetsLocked这个函数从字面不难猜出其意图: 查找有焦点的window。

该函数较长，我们将其拆分开来进行梳理

未找到focused的window，也未找到focused的application

// If there is no currently focused window and no focused application // then drop the event. if (focusedWindowHandle == nullptr && focusedApplicationHandle == nullptr) { ALOGI("Dropping %s event because there is no focused window or focused application in " "display %" PRId32 ".", NamedEnum::string(entry.type).c_str(), displayId); return InputEventInjectionResult::FAILED; }

这种情况下，则drop该事件

未找到focused的window，有focused的application

if (focusedWindowHandle == nullptr && focusedApplicationHandle != nullptr) { if (!mNoFocusedWindowTimeoutTime.has_value()) { // We just discovered that there's no focused window. Start the ANR timer std::chrono::nanoseconds timeout = focusedApplicationHandle->getDispatchingTimeout( DEFAULT_INPUT_DISPATCHING_TIMEOUT); //更新超时时间，该focused事件开始进入计时 mNoFocusedWindowTimeoutTime = currentTime + timeout.count(); mAwaitedFocusedApplication = focusedApplicationHandle; mAwaitedApplicationDisplayId = displayId; ALOGW("Waiting because no window has focus but %s may eventually add a " "window when it finishes starting up. Will wait for %" PRId64 "ms", mAwaitedFocusedApplication->getName().c_str(), millis(timeout)); *nextWakeupTime = *mNoFocusedWindowTimeoutTime; return InputEventInjectionResult::PENDING; } else if (currentTime > *mNoFocusedWindowTimeoutTime) { // Already raised ANR. Drop the event ALOGE("Dropping %s event because there is no focused window", NamedEnum::string(entry.type).c_str()); return InputEventInjectionResult::FAILED; } else { //说明之前已经埋过计时，此时还未到超时时间则继续等待 // Still waiting for the focused window return InputEventInjectionResult::PENDING; } }

重置超时时间

// we have a valid, non-null focused window resetNoFocusedWindowTimeoutLocked();

如果执行到这步的话，则说明本次findFocusedWindowTargetsLocked找到了非空的window，对于这种情况会resetNoFocusedWindowTimeoutLocked。

除此之外，系统还有多个场景下也会触发该重置接口，比如

setFocusedApplicationLocked 当前focused应用发生变化setInputDispatchMode 调用了分发模式resetAndDropEverythingLocked这个接口存在多处会调用的场景，如stopFreezingDisplayLocked、performEnableScreen等场景。

其它窗口异常情况

如果当前window存在异常情况，也会做pending处理，同样可能会成为造成ANR的原因。比如窗口处于paused状态

if (focusedWindowHandle->getInfo()->paused) { ALOGI("Waiting because %s is paused", focusedWindowHandle->getName().c_str()); return InputEventInjectionResult::PENDING; }

还有其他情况也会导致pending，如窗口未连接、窗口连接已满、窗口连接死亡等，不一一列出。

这里提到了造成消息pending的情况，我们自然会想到那什么场景下消息会drop掉呢？

frameworks/native/services/inputflinger/dispatcher/InputDispatcher.cppvoid InputDispatcher::dropInboundEventLocked(const EventEntry& entry, DropReason dropReason) { const char* reason; switch (dropReason) { case DropReason::POLICY: #if DEBUG_INBOUND_EVENT_DETAILS ALOGD("Dropped event because policy consumed it."); #endif reason = "inbound event was dropped because the policy consumed it"; break; case DropReason::DISABLED: if (mLastDropReason != DropReason::DISABLED) { ALOGI("Dropped event because input dispatch is disabled."); } reason = "inbound event was dropped because input dispatch is disabled"; break; case DropReason::APP_SWITCH: ALOGI("Dropped event because of pending overdue app switch."); reason = "inbound event was dropped because of pending overdue app switch"; break; case DropReason::BLOCKED: ALOGI("Dropped event because the current application is not responding and the user " "has started interacting with a different application."); reason = "inbound event was dropped because the current application is not responding " "and the user has started interacting with a different application"; break; case DropReason::STALE: ALOGI("Dropped event because it is stale."); reason = "inbound event was dropped because it is stale"; break; case DropReason::NOT_DROPPED: { LOG_ALWAYS_FATAL("Should not be dropping a NOT_DROPPED event"); return; } }

有如上几种场景会造成消息drop，dropInboundEventLocked的触发时机是在InputDispatcher::dispatchOnceInnerLocked中。

到这里我们已经清楚了埋下超时时间的流程，那么什么时候会检查超时时间有没有到呢？

InputDispatcher.cpp@dispatchOnce-> InputDispatcher.cpp@processAnrsLocked/** * Check if any of the connections' wait queues have events that are too old. * If we waited for events to be ack'ed for more than the window timeout, raise an ANR. * Return the time at which we should wake up next. */ nsecs_t InputDispatcher::processAnrsLocked() { const nsecs_t currentTime = now(); nsecs_t nextAnrCheck = LONG_LONG_MAX; // Check if we are waiting for a focused window to appear. Raise ANR if waited too long if (mNoFocusedWindowTimeoutTime.has_value() && mAwaitedFocusedApplication != nullptr) { if (currentTime >= *mNoFocusedWindowTimeoutTime) { processNoFocusedWindowAnrLocked(); mAwaitedFocusedApplication.reset(); mNoFocusedWindowTimeoutTime = std::nullopt; return LONG_LONG_MIN; } else { //mNoFocusedWindowTimeoutTime代表的是这个window超时的时间点 // Keep waiting. We will drop the event when mNoFocusedWindowTimeoutTime comes. nextAnrCheck = *mNoFocusedWindowTimeoutTime; } } // Check if any connection ANRs are due nextAnrCheck = std::min(nextAnrCheck, mAnrTracker.firstTimeout()); if (currentTime < nextAnrCheck) { // most likely scenario return nextAnrCheck; // everything is normal. Let's check again at nextAnrCheck } // If we reached here, we have an unresponsive connection. sp connection = getConnectionLocked(mAnrTracker.firstToken()); if (connection == nullptr) { ALOGE("Could not find connection for entry %" PRId64, mAnrTracker.firstTimeout()); return nextAnrCheck; } connection->responsive = false; // Stop waking up for this unresponsive connection mAnrTracker.eraseToken(connection->inputChannel->getConnectionToken()); onAnrLocked(connection); return LONG_LONG_MIN; }

如果当前时间已经满足超时时间，则触发onAnrLocked。

void InputDispatcher::onAnrLocked(std::shared_ptr application) { std::string reason = StringPrintf("%s does not have a focused window", application->getName().c_str()); updateLastAnrStateLocked(*application, reason); std::unique_ptr commandEntry = std::make_unique( &InputDispatcher::doNotifyNoFocusedWindowAnrLockedInterruptible); commandEntry->inputApplicationHandle = std::move(application); postCommandLocked(std::move(commandEntry)); }

onAnrLocked这个函数所起到的主要作用是将doNotifyNoFocusedWindowAnrLockedInterruptible通过postCommandLocked塞进队列中。

在下一次触发InputDispatcher.dispatchOnce函数会执行runCommandsLockedInterruptible

void InputDispatcher::dispatchOnce() { nsecs_t nextWakeupTime = LONG_LONG_MAX; { // acquire lock std::scoped_lock _l(mLock); mDispatcherIsAlive.notify_all(); // Run a dispatch loop if there are no pending commands. // The dispatch loop might enqueue commands to run afterwards. if (!haveCommandsLocked()) { dispatchOnceInnerLocked(&nextWakeupTime); } // Run all pending commands if there are any. // If any commands were run then force the next poll to wake up immediately. if (runCommandsLockedInterruptible()) { nextWakeupTime = LONG_LONG_MIN; } //.... }

runCommandsLockedInterruptible函数作用其实比较简单，就是取出所有的Command执行一遍

bool InputDispatcher::runCommandsLockedInterruptible() { if (mCommandQueue.empty()) { return false; } do { std::unique_ptr commandEntry = std::move(mCommandQueue.front()); mCommandQueue.pop_front(); Command command = commandEntry->command; command(*this, commandEntry.get()); // commands are implicitly 'LockedInterruptible' commandEntry->connection.clear(); } while (!mCommandQueue.empty()); return true; }

这里顺便提一下，我们平时分析日志时经常会遇到类似这样的片段

上面的日志片段其实是在processAnrsLocked中打印的，这块日志打印在S上已经被谷歌移除了

一般分析步骤确认是否是系统环境影响

首先判断下是否受系统因素影响，这里所说的系统因素通常指的是整机负载/低内存/系统异常等。

下面以高负载和低内存这两个场景为例进行说明

1. 受整机负载影响

搜索"ANR in"关键词

01-29 06:24:46.618452 1210 5962 I AnrManager: ANR in com.journeyui.calculator (com.journeyui.calculator/.Calculator), time=260439862 01-29 06:24:46.618452 1210 5962 I AnrManager: Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window) 01-29 06:24:46.618452 1210 5962 I AnrManager: Load: 31.7 / 33.43 / 30.98 01-29 06:24:46.618452 1210 5962 I AnrManager: Android time :[2022-01-29 06:24:46.60] [260451.594] 01-29 06:24:46.618452 1210 5962 I AnrManager: CPU usage from 167270ms to 0ms ago (2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860) with 99% awake: 01-29 06:24:46.618452 1210 5962 I AnrManager: 226% 1210/system_server: 173% user + 52% kernel / faults: 1026822 minor 8 major 01-29 06:24:46.618452 1210 5962 I AnrManager: 125% 459/logd: 16% user + 109% kernel / faults: 408 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 29% 21567/com.journeyui.globalsearch: 18% user + 10% kernel / faults: 45071 minor 25 major 01-29 06:24:46.618452 1210 5962 I AnrManager: 26% 639/surfaceflinger: 18% user + 8.6% kernel / faults: 4704 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 26% 20889/com.yulong.android.gamecenter: 16% user + 9.3% kernel / faults: 21143 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 24% 29706/com.sohu.inputmethod.sogou:home: 16% user + 8.6% kernel / faults: 21832 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 24% 545/com.android.messaging: 15% user + 9% kernel / faults: 26023 minor 2 major 01-29 06:24:46.618452 1210 5962 I AnrManager: 19% 803/guardserver: 3% user + 16% kernel //.... 01-29 06:24:46.618452 1210 5962 I AnrManager: 1.7% 3589/com.journeyui.calculator: 1% user + 0.6% kernel / faults: 3365 minor 5 major //..... 01-29 06:24:46.618480 1210 5962 I AnrManager: 85% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirqANR in com.journeyui.calculator ANR进程名Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window)Reason后面跟的是本次ANR原因，上面这个例子中通俗的解释是：事件落到com.tencent.mm/.ui.LauncherUI窗口上，不过该窗口直到超时时间到了仍未响应输入事件，input超时时间系统默认是5s。Load: 31.7 / 33.43 / 30.98前 1，前 5，前 15 分钟的负载，我们通常看变化趋势。2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860 统计的时间区域85% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirq

代表了整体的负载情况，85% TOTAL说明整机负载很高。

图中(4)-(5)之间的片段则是各个进程占据的CPU情况, 发生ANR的进程com.journeyui.calculator的CPU占用只有1.7%

2. 受低内存影响

我们知道通常内存紧张的时候，kswapd线程会活跃起来进行回收内存

比如下面这个案例

kswapd的CPU占据排进top3的话，这个问题受系统低内存影响比较大。

低内存为何会成为ANR的诱发因素呢？

整机一旦陷入低内存，响应度和流畅度都会受到影响，这是因为低内存往往会伴随着IO升高，内存回收线程如kswapd、HeapTaskDaemon会变得活跃。

表现出来的现象就是操作界面如滑动列表明显卡顿、冷启动时间变长、动画顿挫掉帧严重等。

上面提到的这些现象从Systrace中能够直观的看出来，低内存时会出现大量的Uninterruptible Sleep | WakeKill，Block I/O block信息都是wait_on_page_bit_killable。而触发wait_on_page_bit_killable的上游正是do_page_fault。

这点其实比较好理解，低内存时系统往往会竭尽可能的回收内存，可能触发的fast path 回收 \ kswapd 回收 \ direct reclaim 回收 \ LMK杀进程回收等行为，都会造成do_page_fault 高频发生。

另外当出现大量的 IO 操作的时候，应用主线程的 Uninterruptible Sleep 也会变多，此时涉及到 io 操作（比如 view ，读文件，读配置文件、读 odex 文件），都会触发 Uninterruptible Sleep ，导致整个操作的时间变长，这就解释了为何低内存下为何应用响应卡顿。

所以，分析ANR问题时如果遇到kswapd占据很高(top3)，则认为该问题受低内存影响很大。

另外这个时候，对于低内存的案例，搜索"lowmemorykiller"关键词，可以看到问题时间区域会有较多的查杀进程行为，我们通常会关注下"lowmemorykiller"这一行杀的进程adj值，adj值越低，说明当前系统内存越吃紧。

小结：通常拿到一份完整的ANR日志，先看下是否受系统环境因素影响，比如判断是否陷入严重的低内存，是否存在系统整机负载很高等情况。如果存在上述的这些情况，说明本次ANR的进程可能只是受害者。分析堆栈

如果前面已经排除了系统环境影响的话，那么接下来就要分析进程的堆栈。

event日志中搜索"am_anr"关键字

可以看到时间点: 01-25 14:40:44，进程号: 17728

紧接着我们再根据时间戳，找到anr文件夹下对应的trace文件

可以通过Cmd line中的进程名，再次确认下文件没有找错

该份trace文件中搜索关键字"sysTid=17728"，这里的17728就是上面"am_anr"一行中包含的进程号，也是进程的主线程号。

依次介绍下上图中标记出来的(1)-(5)的含义

线程运行状态nice值代表该线程优先级，nice的取值范围为-20到19。通常来说nice的值越大，进程的优先级就越低，获得CPU调用的机会越少，nice值越小，进程的优先级则越高，获得CPU调用的机会越多。utm：该线程在用户态所执行的时间(单位是jiffies）stm：该线程在内核态所执行的时间线程的cpu耗时是两者相加(utm+stm)，utm,stm 单位换算成时间单位为 1 比 10ms。core：后面的数字表示的跑在哪个核上，core=7表示打印这段日志时该线程跑在大核CPU7上。函数调用堆栈，也是我们最为关心的部分。典型案例

下面我们将介绍导致ANR的主要场景案例

主线程耗时

这种情况是最为常见一种类型，也是最容易分析的类型

比如下面这个案例，是com.tencent.qqlive的ANR，callstack如下

通常来说，如果打印的堆栈是该进程内部的堆栈，并且经过业务证实这段代码确实可能存在耗时，那么根据callstack位置找到代码修改即可。

主线程Blocked/Waiting/Sleeping

从上面图中我们可以看到，主线程当前的状态是(1)Blocked，原因是它在等锁(2) 0x06573567，而0x06573567被(3)线程13所持有。

此时我们自然想到去看下tid=13线程的CallStack，在该份trace文件中搜索关键字"0x06573567"找到线程13的CallStack。

主线程陷入Blocked状态的缘由，通常是由于持锁线程在做繁琐的事务，或者是主线程和其它线程发生了死锁。

当然除了主线程陷入Blocked状态这种常见的情况之外，还有一些比较少见的情况。

主线程处于waiting，说明其正在等待其他线程来notify它，堆栈同样是等锁，分析思路一样。主线程处于Sleeping状态，说明当前线程主动调用sleep，其堆栈通常是sleeping on 。Binder阻塞等待

这种案例在项目中比较常见，所谓的Binder阻塞等待指的是什么呢？

比如进程A在其主线程中向进程B发起了Binder请求，进程B因为一些原因比如正在处理耗时消息或网络异常等原因，无法及时响应进程A的Binder请求，造成进程A在主线程上一直阻塞等待Binder的返回结果，最终触发ANR。

比如下面这个案例

从图中可以看到，Keyguard在做native层的Binder通信，并处于阻塞等待对端结果返回的状态中。

这个时候我们很容易会产生这样的疑问：

对于这种等待Binder的案例，我们该如何快速的找到Binder对端？

我们以mtk平台为例，anr文件夹下的binderinfo文件，通常会打印出Binder交互信息。

可以通过搜索关键字"outgoing transaction"来进行查找，这个关键字表示的是当前线程扮演的是Client角色，向其它进程发起Binder。

上图中这一行红色标记处代表的含义是：

进程号为28444的进程中的28536线程，向进程号为22767发起了Binder。

需要注意一点的是：22767:0中的0表示该进程此时没有可用Binder线程。

如果我们在binderinfo 文件中没有找到有价值线索的话，也可以在kernel日志中搜索"binder : release" 关键词，这行日志通常会在Binder所在进程通信结束后打印出来。

Binder线程池耗尽

我们知道应用最多支持16个binder 线程，SystemServer支持最多32个binder 线程。

我们实际项目上，不时会遇到对端Binder 线程池耗尽导致不能响应的案例。

什么情况下会出现Binder 池耗尽的情况呢？

举个例子，进程A短时间内发送很多Binder 请求给进程B，这种情况下就有可能会导致在短时间内，接收端进程B的Binder 线程池中的16个Binder线程，都用来响应进程A的Binder请求。

也就是我们常说的Binder线程池耗尽的情况，此时进程B无法处理进程A发过来的新的Binder请求。

比如下面这段日志

图中可以看到17728这个进程的Binder线程池已经耗尽，这个时候就需要找到发送端是谁及其对应的callstack，如何找对端前面已经讲过，这里不再详细展开。

关于Binder耗尽的情况，通常是由于代码设计上的缺陷，导致短时间内高频发起Binder。

不过还有一种情况也可能会出现，那就是在Monkey测试环境下。

无效堆栈

在我们的实际项目上，经常会遇到这样的情况，日志提供的是完整的，可堆栈看起来却不像"作案"堆栈，即出现的堆栈并不像是真正的凶手。

常见的一种情况: 堆栈落在nativePollOnce上。

这种情况通常说明当前主线程的消息队列是空闲的，此时在等待处理下一个msg，打印日志时真正的block消息已经走完了。

我们以下面这个计算器的anr为例

01-29 06:24:46.618452 1210 5962 I AnrManager: ANR in com.journeyui.calculator (com.journeyui.calculator/.Calculator), time=260439862 01-29 06:24:46.618452 1210 5962 I AnrManager: Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window) 01-29 06:24:46.618452 1210 5962 I AnrManager: Load: 31.7 / 33.43 / 30.98 01-29 06:24:46.618452 1210 5962 I AnrManager: Android time :[2022-01-29 06:24:46.60] [260451.594] 01-29 06:24:46.618452 1210 5962 I AnrManager: CPU usage from 167270ms to 0ms ago (2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860) with 99% awake: 01-29 06:24:46.618452 1210 5962 I AnrManager: 226% 1210/system_server: 173% user + 52% kernel / faults: 1026822 minor 8 major 01-29 06:24:46.618452 1210 5962 I AnrManager: 125% 459/logd: 16% user + 109% kernel / faults: 408 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 29% 21567/com.journeyui.globalsearch: 18% user + 10% kernel / faults: 45071 minor 25 major 01-29 06:24:46.618452 1210 5962 I AnrManager: 26% 639/surfaceflinger: 18% user + 8.6% kernel / faults: 4704 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 26% 20889/com.yulong.android.gamecenter: 16% user + 9.3% kernel / faults: 21143 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 24% 29706/com.sohu.inputmethod.sogou:home: 16% user + 8.6% kernel / faults: 21832 minor 01-29 06:24:46.618452 1210 5962 I AnrManager: 24% 545/com.android.messaging: 15% user + 9% kernel / faults: 26023 minor 2 major //... 01-29 06:24:46.618452 1210 5962 I AnrManager: 1.7% 3589/com.journeyui.calculator: 1% user + 0.6% kernel / faults: 3365 minor 5 major //... 01-29 06:24:46.618480 1210 5962 I AnrManager: 75% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirq

正如我们前面所讲的策略，首先看下是否受系统环境影响。

从上面的日志片段可以看出，整机负载较高达到了75%，但是前台进程com.journeyui.calculator占用并不高只有1.7%。

top中没有kswapd身影，排除低内存的影响，所以这个问题在一定程度上受整机高负载的影响。

PS: ANR发生时SystemServer占据稍高可能是正常的，因为Dump Trace时需要获取系统整体及各进程 CPU 使用情况，短时间内会造成SystemServer升高。

接着event日志中搜索"am_anr"关键字

01-29 06:24:34.907471 1210 5962 I am_anr : [0,3589,com.journeyui.calculator,684244549, Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/ .Calculator t1837} does not have a focused window)]

根据时间戳找到对应的anr文件

此时我们注意到堆栈落在了nativePollOnce上，前面说过落在nativePollOnce上，说明应用此时已经处于idle状态了。

对于这种情况，说明耗时消息已埋没在历史消息中，历史消息的耗时可能存在下面的几种情况

应用主线程历史调度中存在严重耗时的消息应用主线程历史调度中存在多个耗时的消息应用主线程历史调度中存在大量消息比如高频发送消息应用主线程本身并不耗时，而是受到系统环境因素影响(IO/低内存/高负载等)

那么历史调度中的耗时消息我们应该如何得知呢？

通常手机厂商会做日志增强，常见的思路如下:

对于主线程的binder transaction 耗时情况，超出设定阈值则输出调用信息。当线程等锁时间超出设定阈值，则输出当前的持锁状态。主线程的生命周期回调方法执行时间超出设定阈值，则输出相应信息。对于非异步Binder调用耗时超出设定阈值的时候，输出Binder信息。

对于一些头部应用厂商如字节跳动有自研的Raster消息监控平台，和手机厂商做的日志增强目的是一样的，都是为了尽可能多的收集线索。

除了落在nativePollOnce的情况，还有一种情况则更加隐蔽，容易将我们带偏分析的方向。那就是堆栈打印出来的确实是应用自身的堆栈。

但是根据堆栈找到对应代码后发现这段代码不可能会出现耗时，说明这段堆栈可能只是充当了"替罪羊"的角色，而真正的"凶手"早已藏身在了历史消息中。

用内存问题

我们实际项目中，不时会遇到应用自身内存使用不当导致的ANR。

比如下面的美团ANR案例

01-08 14:53:20.130 1074 32039 I AnrManager: ANR in com.sankuai.meituan (com.sankuai.meituan/com.meituan.android.pt.homepage.activity.MainActivity), time=48329538 01-08 14:53:20.130 1074 32039 I AnrManager: Reason: Input dispatching timed out (c961943 com.sankuai.meituan/com.meituan.android.pt.homepage.activity.MainActivity (server) is not responding. Waited 8006ms for MotionEvent) 01-08 14:53:20.130 1074 32039 I AnrManager: Load: 27.74 / 27.04 / 27.19 01-08 14:53:20.130 1074 32039 I AnrManager: Android time :[2022-01-08 14:53:20.10] [48351.410] 01-08 14:53:20.130 1074 32039 I AnrManager: CPU usage from 9706ms to 0ms ago (2022-01-08 14:52:48.524 to 2022-01-08 14:52:58.230): 01-08 14:53:20.130 1074 32039 I AnrManager: 100% 32613/com.sankuai.meituan: 99% user + 1.5% kernel / faults: 72075 minor 01-08 14:53:20.130 1074 32039 I AnrManager: 24% 16662/com.ss.android.ugc.aweme:miniappX: 17% user + 7.3% kernel / faults: 1762 minor 01-08 14:53:20.130 1074 32039 I AnrManager: 17% 4548/com.ss.android.ugc.aweme: 11% user + 5.9% kernel / faults: 2500 minor 01-08 14:53:20.130 1074 32039 I AnrManager: 11% 1074/system_server: 8% user + 3.6% kernel / faults: 6412 minor 1 major //... 01-08 14:53:20.130 1074 32039 I AnrManager: 30% TOTAL: 21% user + 8.1% kernel + 0.1% iowait + 1% softirq

从上面日志片段可以看到整机负载并不高，且kswapd占比很低，排除系统因素的影响。

01-08 14:52:58.243 1074 32039 I am_anr : [0,32613,com.sankuai.meituan,949501508, Input dispatching timed out (c961943 com.sankuai.meituan/com.meituan.android.pt.homepage.activity.MainActivity (server) is not responding. Waited 8006ms for MotionEvent)]

时间点14:52:58 进程号32613

这份日志缺少anr文件，所以直接看系统日志，根据上面的时间点往前推(取决于该ANR类型对应的阈值时间)，找到案发最初的时间点。

这个案例中，我们在案发时间点附近，发现大量的GC片段且很多GC耗时都较长。

Clamp target GC heap from这行日志是在SetIdealFootprint即调整目标堆上限值时会打印，这块不太熟悉的话可以参见我们之前发表过的一篇文章。

上面这段日志说明当前应用堆使用已超出上限512M，为了满足新分配的对象内存需求，系统一直持续不断的对该应用进行阻塞GC(GC分为不同力度，阻塞GC说明应用此时内存情况比较糟糕)。

通过日志可以发现，尽管应用持续不断的阻塞GC，应用内存依旧没有降下来。

这种情况下很可能是出现了应用内存泄漏的情况。

关于应用内存使用不当，通常有如下几种情况

频繁的生成临时对象导致堆内存增长迅速，达到下次堆GC触发阈值后便会触发Bg GC，进而导致回收线程跑大核和前台应用争抢CPU。另外GC回收阶段会存在一次锁堆，应用的主线程会被pause，这种情况下势必会造成应用使用卡顿甚至ANR。还有一种比较常见的情况是应用发生了较为严重的内存泄漏，导致GC一直无法回收足够的内存。应用申请大内存触发阻塞GC以便能够申请到足够的内存，这种情况通常会引起应用界面的黑屏或者明显的卡顿。我们知道系统低内存时会触发OnTrimMemory回调，如果应用在OnTrimMemory中并且是在主线程中直接调用显式GC接口即System.gc()，也容易引起应用卡顿，对于这个接口的使用需要谨慎。

上面这些情况虽不一定会导致ANR，但是应用操作上的卡顿可能在所难免。

结语

ANR是卡顿的一种严重表现形式，当我们遇到卡顿问题时，应趁早解决，防患于未然。

到这里，关于ANR的介绍到此为止，希望通过本文，在日后处理ANR问题时，能够多一些思路。

针对上述中所聊到的 ANR问题，方便大家往后遇到此类问题更好的解决，特此分享一个Android 性能优化的学习笔记，该笔记里面不仅记录了卡顿问题，还有启动优化、UI渲染优化、崩溃优化、内存优化、卡顿优化、存储优化、网络优化、耗电优化、多线程并发优化、体积包优化等。有需要参考学习的直接 点击这里查看获取方式或私信回复 666 货取！！！

【本文地址】

公司简介

联系我们